kvserver: add TestFlowControlSendQueueRangeSplitMerge test #136258

kvoli · 2024-11-26T23:31:19Z

Add a new rac2 flow control integration test,
TestFlowControlSendQueueRangeSplitMerge.

This test takes the following steps:

-- We will exhaust the tokens across all streams while admission is blocked on
-- n3, using a single 4 MiB (deduction, the write itself is small) write. Then,
-- we will write a 1 MiB put to the range, split it, write a 1 MiB put to the
-- LHS range, merge the ranges, and write a 1 MiB put to the merged range. We
-- expect that at each stage where a send queue develops n1->s3, the send queue
-- will be flushed by the range merge and range split range operations.``sql

Note that the RHS is not written to post-split, pre-merge. See the
relevant comments, this will be resolved via #136649, or some variation,
which enforces the timely replication on subsume requests.

Part of: #132614
Release note: None

blathers-crl · 2024-11-26T23:31:23Z

Your pull request contains more than 1000 changes. It is strongly encouraged to split big PRs into smaller chunks.

_{🦉 Hoot! I am a Blathers, a bot for CockroachDB. My owner is dev-inf.}

cockroach-teamcity · 2024-11-26T23:31:34Z

This change is

kvoli · 2024-11-27T20:27:19Z

Should be good for review, ignoring the first commit (I won't merge this until after we merge the split-out fixes from #136077).

ptal @sumeerbhola.

sumeerbhola

Reviewed 2 of 2 files at r2.
Reviewable status: complete! 1 of 0 LGTMs obtained (waiting on @kvoli)

pkg/kv/kvserver/flow_control_integration_test.go line 5606 at r2 (raw file):

	h.comment(`(Sending 1 MiB put request to post-split RHS range)`)
	h.put(ctx, k, 1, admissionpb.NormalPri)

should this be writing to right.StartKey since that is the start of the RHS. k seems to be the LHS.

Perhaps we should write to both LHS and RHS, to make sure everything is working as expected. The SubsumeRequest force-flush will flush on the RHS, and the txn commit (whose txn record is on the LHS) should cause a force-flush on the LHS.

kvoli · 2024-12-05T20:23:15Z

@sumeerbhola are you okay merging this as is and following up with a write to the RHS post-split, pre-merge, after we resolve the subsume timely replication issue? I've left a todo for this.

sumeerbhola

sounds good

Reviewable status: complete! 1 of 0 LGTMs obtained (waiting on @kvoli)

kvoli · 2024-12-06T23:33:10Z

Rebased and pushed a small commit, identical to changes applied in #136182, which changes the test to use leader leases, in order to prevent the lead changing and extend testing.

I looked through the extended CI test failure and couldn't repro over 1k runs. I did manage to repro somewhere in 10k runs last night, however the best indication I got for a cause was that we saw an unexpected msg_app heartbeat due to overload (liveness was failing >3s, 2s handle raft ready on the range). I'm hoping the above change deflakes the test.

kvoli · 2024-12-07T01:14:41Z

Nvm, that didn't do the trick. I'm not going to merge this today.

kvoli · 2024-12-09T21:48:23Z

For reference, this is the failure with additional handle raft event logging:

https://gist.github.com/kvoli/1f743e52bcfb94e82670ab87b3fd7954

kvoli · 2024-12-09T22:14:12Z

With some more logging and only the logs for the RHS split range, from creation to a send queue forming:

Details

I241209 22:03:38.212776 545 kv/kvserver/kvflowcontrol/rac2/token_tracker.go:87 ⋮ [T1,Vsystem,n1] 540  tracking ‹+1.0 MiB› flow control tokens for pri=LowPri stream=t‹1›/s‹3› log-position=6/25
I241209 22:03:38.212869 545 kv/kvserver/kvflowcontrol/rac2/token_counter.go:630 ⋮ [T1,Vsystem,n1] 541  adjusted send flow tokens (wc=elastic stream=t‹1›/s‹3› delta=‹-1.0 MiB› flag=‹force_flush›): regular=‹+0 B› elastic=‹-3.0 MiB›
I241209 22:03:38.213947 4914 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n2] 542   [raft] r75 Raft message ‹1->2 MsgPreVote Term:6 Log:5/10›
I241209 22:03:38.214470 4981 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n3] 543   [raft] r75 Raft message ‹1->3 MsgPreVote Term:6 Log:5/10›
I241209 22:03:38.215471 4992 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n1] 545   [raft] r75 Raft message ‹2->1 MsgPreVoteResp Term:6 Log:0/0›
I241209 22:03:38.216866 4914 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n2] 546   [raft] r75 Raft message ‹1->2 MsgVote Term:6 Log:5/10›
I241209 22:03:38.217277 4981 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n3] 547   [raft] r75 Raft message ‹1->3 MsgVote Term:6 Log:5/10›
I241209 22:03:38.218295 5012 kv/kvserver/raft_transport.go:738 ⋮ [T1,Vsystem,n3] 548  informing n1 of 1 local store ID(s) (s3) over the raft transport[default]
I241209 22:03:38.219046 5016 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n1] 549   [raft] r75 Raft message ‹3->1 MsgPreVoteResp Term:6 Log:0/0›
I241209 22:03:38.219282 5016 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n1] 550   [raft] r75 Raft message ‹3->1 MsgVoteResp Term:6 Log:0/0›
I241209 22:03:38.219877 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:695 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 551  r75 creating range controller
I241209 22:03:38.220298 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 552  r75/1 handle raft event: send_queue_stats={[{false true {‹1› 0 0}} {false true {‹2› 0 0}} {false true {‹3› 0 0}}]} event=mode=‹1› term=6 snap=‹<nil>›
I241209 22:03:38.220298 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 552 +‹[›
I241209 22:03:38.220298 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 552 +  replicas_state_info(3)=[3=state=StateProbe match=0 next=11‹ ›1=state=StateReplicate match=10 next=12‹ ›2=state=StateProbe match=0 next=11]
I241209 22:03:38.220298 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 552 +  entries(1)=(6/11 EntryNormal)
I241209 22:03:38.220298 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 552 +  msg_apps(2)=
I241209 22:03:38.220298 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 552 +    /2:
I241209 22:03:38.220298 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 552 +‹      ›1->2 6/10 log_term=5 match=0 commit=10 lead=0 vote=0 reject=false reject_hint=0
I241209 22:03:38.220298 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 552 +‹        entries=›(6/11 EntryNormal)
I241209 22:03:38.220298 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 552 +    /3:
I241209 22:03:38.220298 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 552 +‹      ›1->3 6/10 log_term=5 match=0 commit=10 lead=0 vote=0 reject=false reject_hint=0
I241209 22:03:38.220298 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 552 +‹        entries=›(6/11 EntryNormal)
I241209 22:03:38.220298 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 552 +‹]›
I241209 22:03:38.220440 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2235 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 553  creating send stream t‹1›/s‹1› for replica (n1,s1):1
I241209 22:03:38.220993 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 554  r75/1 handle raft event: send_queue_stats={[{true false {‹1› 0 0}} {false true {‹2› 0 0}} {false true {‹3› 0 0}}]} event=mode=‹1› term=0 snap=‹<nil>›
I241209 22:03:38.220993 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 554 +‹[›
I241209 22:03:38.220993 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 554 +  replicas_state_info(3)=[1=state=StateReplicate match=11 next=12‹ ›2=state=StateProbe match=0 next=11‹ ›3=state=StateProbe match=0 next=11]
I241209 22:03:38.220993 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 554 +  entries(0)=
I241209 22:03:38.220993 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 554 +  msg_apps(0)=
I241209 22:03:38.220993 471 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 554 +‹]›
I241209 22:03:38.221086 4914 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n2] 555   [raft] r75 Raft message ‹1->2 MsgFortifyLeader Term:6 Log:0/0›
I241209 22:03:38.221229 4914 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n2] 557   [raft] r75 Raft message ‹1->2 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal <omitted>]›
I241209 22:03:38.223473 4992 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n1] 558   [raft] r75 Raft message ‹2->1 MsgVoteResp Term:6 Log:0/0›
I241209 22:03:38.223526 4981 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n3] 559   [raft] r75 Raft message ‹1->3 MsgFortifyLeader Term:6 Log:0/0›
I241209 22:03:38.223635 4992 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n1] 560   [raft] r75 Raft message ‹2->1 MsgFortifyLeaderResp Term:6 Log:0/0 LeadEpoch:1›
I241209 22:03:38.223738 4992 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n1] 562   [raft] r75 Raft message ‹2->1 MsgAppResp Term:6 Log:0/11 Commit:10›
I241209 22:03:38.223653 4981 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n3] 563   [raft] r75 Raft message ‹1->3 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal <omitted>]›
I241209 22:03:38.224448 474 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 564  r75/1 handle raft event: send_queue_stats={[{true false {‹1› 0 0}} {false true {‹2› 0 0}} {false true {‹3› 0 0}}]} event=mode=‹1› term=0 snap=‹<nil>›
I241209 22:03:38.224448 474 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 564 +‹[›
I241209 22:03:38.224448 474 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 564 +  replicas_state_info(3)=[1=state=StateReplicate match=11 next=12‹ ›2=state=StateReplicate match=11 next=12‹ ›3=state=StateProbe match=0 next=11]
I241209 22:03:38.224448 474 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 564 +  entries(0)=
I241209 22:03:38.224448 474 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 564 +  msg_apps(2)=
I241209 22:03:38.224448 474 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 564 +    /2:
I241209 22:03:38.224448 474 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 564 +‹      ›1->2 6/10 log_term=5 match=0 commit=10 lead=0 vote=0 reject=false reject_hint=0
I241209 22:03:38.224448 474 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 564 +‹        entries=›(6/11 EntryNormal)
I241209 22:03:38.224448 474 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 564 +‹      ›1->2 6/11 log_term=6 match=11 commit=11 lead=0 vote=0 reject=false reject_hint=0
I241209 22:03:38.224448 474 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 564 +‹        entries=›
I241209 22:03:38.224448 474 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 564 +‹]›
I241209 22:03:38.224600 474 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2235 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 565  creating send stream t‹1›/s‹2› for replica (n2,s2):2
I241209 22:03:38.225216 4914 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n2] 567   [raft] r75 Raft message ‹1->2 MsgApp Term:6 Log:5/10 Commit:10 Entries:[6/11 EntryNormal <omitted>]›
I241209 22:03:38.225604 474 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 568  r75/1 handle raft event: send_queue_stats={[{true false {‹1› 0 0}} {true false {‹2› 0 0}} {false true {‹3› 0 0}}]} event=mode=‹1› term=0 snap=‹<nil>›
I241209 22:03:38.225604 474 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 568 +‹[›
I241209 22:03:38.225604 474 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 568 +  replicas_state_info(3)=[1=state=StateReplicate match=11 next=12‹ ›2=state=StateReplicate match=11 next=12‹ ›3=state=StateProbe match=0 next=11]
I241209 22:03:38.225604 474 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 568 +  entries(0)=
I241209 22:03:38.225604 474 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 568 +  msg_apps(0)=
I241209 22:03:38.225604 474 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 568 +‹]›
I241209 22:03:38.225725 4994 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n1] 569   [raft] r75 Raft message ‹3->1 MsgFortifyLeaderResp Term:6 Log:0/0 LeadEpoch:1›
I241209 22:03:38.225833 4994 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n1] 570   [raft] r75 Raft message ‹3->1 MsgAppResp Term:6 Log:0/11 Commit:10›
I241209 22:03:38.226113 4914 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n2] 571   [raft] r75 Raft message ‹1->2 MsgApp Term:6 Log:6/11 Commit:11›
I241209 22:03:38.226124 4992 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n1] 572   [raft] r75 Raft message ‹2->1 MsgAppResp Term:6 Log:0/11 Commit:10›
I241209 22:03:38.226502 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 574  r75/1 handle raft event: send_queue_stats={[{true false {‹1› 0 0}} {true false {‹2› 0 0}} {false true {‹3› 0 0}}]} event=mode=‹1› term=6 snap=‹<nil>›
I241209 22:03:38.226502 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 574 +‹[›
I241209 22:03:38.226502 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 574 +  replicas_state_info(3)=[1=state=StateReplicate match=11 next=13‹ ›2=state=StateReplicate match=11 next=12‹ ›3=state=StateProbe match=0 next=11]
I241209 22:03:38.226502 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 574 +  entries(1)=(6/12 EntryNormal)
I241209 22:03:38.226502 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 574 +  msg_apps(2)=
I241209 22:03:38.226502 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 574 +    /3:
I241209 22:03:38.226502 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 574 +‹      ›1->3 6/10 log_term=5 match=0 commit=11 lead=0 vote=0 reject=false reject_hint=0
I241209 22:03:38.226502 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 574 +‹        entries=›(6/11 EntryNormal)
I241209 22:03:38.226502 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 574 +‹]›
I241209 22:03:38.226736 4992 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n1] 575   [raft] r75 Raft message ‹2->1 MsgAppResp Term:6 Log:0/11 Commit:11›
I241209 22:03:38.226983 4981 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n3] 576   [raft] r75 Raft message ‹1->3 MsgApp Term:6 Log:5/10 Commit:11 Entries:[6/11 EntryNormal <omitted>]›
I241209 22:03:38.227078 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 577  r75/1 handle raft event: send_queue_stats={[{true false {‹1› 0 0}} {true false {‹2› 0 0}} {false true {‹3› 0 0}}]} event=mode=‹1› term=0 snap=‹<nil>›
I241209 22:03:38.227078 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 577 +‹[›
I241209 22:03:38.227078 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 577 +  replicas_state_info(3)=[1=state=StateReplicate match=11 next=13‹ ›2=state=StateReplicate match=11 next=13‹ ›3=state=StateReplicate match=11 next=12]
I241209 22:03:38.227078 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 577 +  entries(0)=
I241209 22:03:38.227078 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 577 +  msg_apps(2)=
I241209 22:03:38.227078 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 577 +    /3:
I241209 22:03:38.227078 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 577 +‹      ›1->3 6/11 log_term=6 match=11 commit=11 lead=0 vote=0 reject=false reject_hint=0
I241209 22:03:38.227078 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 577 +‹        entries=›
I241209 22:03:38.227078 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 577 +‹]›
I241209 22:03:38.227170 4914 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n2] 578   [raft] r75 Raft message ‹1->2 MsgApp Term:6 Log:6/11 Commit:11 Entries:[6/12 EntryNormal <omitted>]›
I241209 22:03:38.227221 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:2235 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 579  creating send stream t‹1›/s‹3› for replica (n3,s3):3
I241209 22:03:38.227542 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 580  r75/1 handle raft event: send_queue_stats={[{true false {‹1› 0 0}} {true false {‹2› 0 0}} {true true {‹3› 500 1}}]} event=mode=‹1› term=0 snap=‹<nil>›
I241209 22:03:38.227542 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 580 +‹[›
I241209 22:03:38.227542 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 580 +  replicas_state_info(3)=[1=state=StateReplicate match=12 next=13‹ ›2=state=StateReplicate match=11 next=13‹ ›3=state=StateReplicate match=11 next=12]
I241209 22:03:38.227542 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 580 +  entries(0)=
I241209 22:03:38.227542 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 580 +  msg_apps(0)=
I241209 22:03:38.227542 476 kv/kvserver/kvflowcontrol/rac2/range_controller.go:1085 ⋮ [T1,Vsystem,n1,s1,r75/1:‹{\xfa\x00-/Max}›,raft] 580 +‹]›
I241209 22:03:38.227778 4994 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n1] 581   [raft] r75 Raft message ‹3->1 MsgAppResp Term:6 Log:0/11 Commit:11›
I241209 22:03:38.228001 4981 kv/kvserver_test/client_raft_helpers_test.go:106 ⋮ [T1,Vsystem,n3] 582   [raft] r75 Raft message ‹1->3 MsgApp Term:6 Log:6/11 Commit:11›

Add a new rac2 flow control integration test, `TestFlowControlSendQueueRangeSplitMerge`. This test takes the following steps: ```sql -- We will exhaust the tokens across all streams while admission is blocked on -- n3, using a single 4 MiB (deduction, the write itself is small) write. Then, -- we will write a 1 MiB put to the range, split it, write a 1 MiB put to the -- LHS range, merge the ranges, and write a 1 MiB put to the merged range. We -- expect that at each stage where a send queue develops n1->s3, the send queue -- will be flushed by the range merge and range split range operations.``sql ``` Note that the RHS is not written to post-split, pre-merge. See the relevant comments, this will be resolved via cockroachdb#136649, or some variation, which enforces the timely replication on subsume requests. Also note that epoch leases are used in the test, the added todo describes why this is currently necessary and an intention to re-enable them. Part of: cockroachdb#132614 Release note: None

kvoli · 2024-12-10T18:52:02Z

I believe this deflaked the test, judging by no failures. I'm going to merge, as there were only test changes after the review, which reduce overrode the lease type.

kvoli · 2024-12-10T18:52:19Z

bors r=sumeerbhola

craig · 2024-12-10T20:02:08Z

Build succeeded:

kvoli self-assigned this Nov 26, 2024

kvoli force-pushed the 241126.rac2-send-queue-test-split-etc branch from c45a091 to fc7bd4d Compare November 27, 2024 20:06

kvoli requested a review from sumeerbhola November 27, 2024 20:27

kvoli marked this pull request as ready for review November 27, 2024 20:27

kvoli requested review from a team as code owners November 27, 2024 20:27

sumeerbhola approved these changes Dec 2, 2024

View reviewed changes

This was referenced Dec 2, 2024

kvserver: [dnm] add TestFlowControlSendQueueRangeSplitMerge test (picked) #136495

Closed

kvserver: add ff index to TestFlowControlSendQueueRange* #136512

Closed

kvoli force-pushed the 241126.rac2-send-queue-test-split-etc branch from fc7bd4d to 227bdb1 Compare December 2, 2024 22:08

kvoli requested review from a team as code owners December 2, 2024 22:08

kvoli requested review from DarrylWong, vidit-bhat and angles-n-daemons and removed request for a team, DarrylWong, vidit-bhat and angles-n-daemons December 2, 2024 22:08

kvoli force-pushed the 241126.rac2-send-queue-test-split-etc branch from 227bdb1 to f25fb10 Compare December 2, 2024 22:14

kvoli force-pushed the 241126.rac2-send-queue-test-split-etc branch 5 times, most recently from ac150e4 to 5673ddc Compare December 3, 2024 20:39

kvoli requested a review from sumeerbhola December 3, 2024 20:52

kvoli force-pushed the 241126.rac2-send-queue-test-split-etc branch 2 times, most recently from a009538 to 93c17ea Compare December 3, 2024 23:31

kvoli removed the request for review from a team December 4, 2024 00:36

kvoli force-pushed the 241126.rac2-send-queue-test-split-etc branch 3 times, most recently from fe6e749 to 069d578 Compare December 5, 2024 20:22

sumeerbhola approved these changes Dec 6, 2024

View reviewed changes

kvoli force-pushed the 241126.rac2-send-queue-test-split-etc branch from 069d578 to 69ab1fb Compare December 6, 2024 23:28

kvoli force-pushed the 241126.rac2-send-queue-test-split-etc branch 2 times, most recently from 84cc33f to 89f87a5 Compare December 9, 2024 21:07

kvoli force-pushed the 241126.rac2-send-queue-test-split-etc branch from 89f87a5 to 202bb43 Compare December 10, 2024 16:47

craig bot merged commit 95d95a6 into cockroachdb:master Dec 10, 2024
21 of 22 checks passed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

kvserver: add TestFlowControlSendQueueRangeSplitMerge test #136258

kvserver: add TestFlowControlSendQueueRangeSplitMerge test #136258

kvoli commented Nov 26, 2024 •

edited

Loading

blathers-crl bot commented Nov 26, 2024

cockroach-teamcity commented Nov 26, 2024

kvoli commented Nov 27, 2024

sumeerbhola left a comment

kvoli commented Dec 5, 2024

sumeerbhola left a comment

kvoli commented Dec 6, 2024

kvoli commented Dec 7, 2024

kvoli commented Dec 9, 2024

kvoli commented Dec 9, 2024

kvoli commented Dec 10, 2024

kvoli commented Dec 10, 2024

craig bot commented Dec 10, 2024

kvserver: add TestFlowControlSendQueueRangeSplitMerge test #136258

kvserver: add TestFlowControlSendQueueRangeSplitMerge test #136258

Conversation

kvoli commented Nov 26, 2024 • edited Loading

blathers-crl bot commented Nov 26, 2024

cockroach-teamcity commented Nov 26, 2024

kvoli commented Nov 27, 2024

sumeerbhola left a comment

Choose a reason for hiding this comment

kvoli commented Dec 5, 2024

sumeerbhola left a comment

Choose a reason for hiding this comment

kvoli commented Dec 6, 2024

kvoli commented Dec 7, 2024

kvoli commented Dec 9, 2024

kvoli commented Dec 9, 2024

kvoli commented Dec 10, 2024

kvoli commented Dec 10, 2024

craig bot commented Dec 10, 2024

kvoli commented Nov 26, 2024 •

edited

Loading